Skip to content

[opt](test) Avoid a 10s heartbeat wait in every FE unit test class - #66195

Open
morningman wants to merge 5 commits into
apache:masterfrom
morningman:opt-fe-ut
Open

[opt](test) Avoid a 10s heartbeat wait in every FE unit test class#66195
morningman wants to merge 5 commits into
apache:masterfrom
morningman:opt-fe-ut

Conversation

@morningman

Copy link
Copy Markdown
Contributor

What problem does this PR solve?

Every test class deriving from TestWithFeService spends about 12 seconds in createDorisCluster(), and roughly 10 of those seconds are pure idle waiting.

Daemon.run() runs one cycle before sleeping, so HeartbeatMgr's first cycle completes while createDorisCluster() has not registered any backend yet. checkBEHeartbeat() then has to wait for the second cycle, which is heartbeat_interval_second (default 10) away.

This is not a niche cost: 304 test classes in fe-core start an FE, and 215 of them (71%) live under nereids — which is why nereids dominates FE UT wall time.

Evidence that this is a timer rather than real work: six synthetic classes that only start the FE and assert once took 11.95 / 12.07 / 12.06 / 11.93 / 12.08 / 12.08 s — a spread of ±0.08s.

What is changed?

  • Set heartbeat_interval_second = 1 at the start of beforeAll().
    • Placed before beforeCreatingConnectContext() so subclasses that set the interval explicitly (DecommissionBackendTest, BeDownCancelCloneTest) still override it.
    • Placed before the Env singleton is created, so HeartbeatMgr picks up the new interval.
    • Deliberately not put into MockedFrontend.MIN_FE_CONF: DorisFE.start() would load it from fe.conf and silently override those subclasses.
  • Make checkBEHeartbeatStatus() check before sleeping, and poll at 20ms instead of sleeping a fixed 1s before each check. The overall timeout budget is unchanged.

Measurements

20 nereids.trees.plans.commands test classes, 43 tests, all passing before and after:

config wall clock reported test time
before, fork=1 399s 283s
after, fork=1 211s 95s
after, fork=4 67s

A synthetic class that only starts the FE and asserts once: 12.0s -> 2.83s.

Also verified separately: DecommissionBackendTest (overrides the interval to 5) and TabletHealthTest (exercises checkBELostHeartbeat) pass.

Release note

None

Check List

  • Test
    • Regression test — not applicable, this only changes the FE unit test harness
    • Unit Test — verified on a 26-class sample; this PR is a draft precisely to get a full CI run, since the change touches the base class of 304 test classes and the risk to validate is timing-sensitive flakiness
  • Behavior changed: No (test-only)
  • Does this need documentation? No

🤖 Generated with Claude Code

@hello-stephen

Copy link
Copy Markdown
Contributor

Thank you for your contribution to Apache Doris.
Don't know what should be done next? See How to process your PR.

Please clearly describe your PR:

  1. What problem was fixed (it's best to include specific error reporting information). How it was fixed.
  2. Which behaviors were modified. What was the previous behavior, what is it now, why was it modified, and what possible impacts might there be.
  3. What features were added. Why was this function added?
  4. Which code was refactored and why was this part of the code refactored?
  5. Which functions were optimized and what is the difference before and after the optimization?

@morningman

Copy link
Copy Markdown
Contributor Author

run buildall

@morningman
morningman marked this pull request as ready for review July 28, 2026 15:26
@hello-stephen

Copy link
Copy Markdown
Contributor
TPC-H: Total hot run time: 29158 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 89257f09d3fb2a9fd4b333373ba16e5c64754073, data reload: false

------ Round 1 ----------------------------------
============================================
q1	17834	4091	4046	4046
q2	2034	321	194	194
q3	10273	1361	820	820
q4	4700	472	338	338
q5	7551	867	565	565
q6	191	167	135	135
q7	750	826	598	598
q8	10023	1577	1570	1570
q9	5887	4359	4338	4338
q10	6822	1714	1463	1463
q11	506	345	320	320
q12	762	585	460	460
q13	18076	3310	2745	2745
q14	269	271	241	241
q15	q16	780	776	720	720
q17	1707	1095	806	806
q18	6911	5730	5575	5575
q19	1657	1333	1116	1116
q20	761	723	572	572
q21	5773	2640	2243	2243
q22	425	356	293	293
Total cold run time: 103692 ms
Total hot run time: 29158 ms

----- Round 2, with runtime_filter_mode=off -----
============================================
q1	4408	4290	4286	4286
q2	288	315	208	208
q3	4528	4935	4408	4408
q4	2036	2132	1340	1340
q5	4407	4247	4306	4247
q6	228	175	123	123
q7	1674	2161	1661	1661
q8	2474	2097	2038	2038
q9	7713	7729	7723	7723
q10	4682	4644	4259	4259
q11	574	412	411	411
q12	893	761	531	531
q13	3273	3506	3038	3038
q14	315	317	284	284
q15	q16	701	732	651	651
q17	1329	1317	1308	1308
q18	7832	7426	6787	6787
q19	1101	1120	1067	1067
q20	2219	2192	1931	1931
q21	5192	4510	4342	4342
q22	514	445	400	400
Total cold run time: 56381 ms
Total hot run time: 51043 ms

@hello-stephen

Copy link
Copy Markdown
Contributor
TPC-DS: Total hot run time: 176627 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpcds-tools
TPC-DS sf100 test result on commit 89257f09d3fb2a9fd4b333373ba16e5c64754073, data reload: false

query5	4340	644	481	481
query6	489	243	215	215
query7	4854	600	330	330
query8	328	186	178	178
query9	8787	3989	3982	3982
query10	486	345	316	316
query11	5940	2371	2103	2103
query12	159	102	105	102
query13	1262	611	465	465
query14	6457	5193	4864	4864
query14_1	4245	4223	4231	4223
query15	223	203	174	174
query16	1003	486	458	458
query17	1124	717	572	572
query18	2629	488	336	336
query19	200	181	150	150
query20	112	112	104	104
query21	225	153	135	135
query22	13623	13501	13326	13326
query23	17322	16542	16036	16036
query23_1	16270	16238	16262	16238
query24	7476	1781	1267	1267
query24_1	1294	1256	1270	1256
query25	541	428	350	350
query26	1336	342	199	199
query27	2669	601	361	361
query28	4450	1961	1956	1956
query29	1051	611	470	470
query30	325	261	235	235
query31	1112	1085	964	964
query32	102	61	62	61
query33	500	309	245	245
query34	1161	1133	644	644
query35	768	773	663	663
query36	1018	1036	875	875
query37	150	113	97	97
query38	1872	1692	1636	1636
query39	869	866	874	866
query39_1	838	828	826	826
query40	248	163	141	141
query41	65	64	68	64
query42	100	95	92	92
query43	319	315	274	274
query44	1401	737	736	736
query45	196	178	171	171
query46	1061	1173	759	759
query47	2157	2139	2058	2058
query48	414	395	297	297
query49	583	420	313	313
query50	1120	425	330	330
query51	10722	10733	10819	10733
query52	95	84	73	73
query53	241	273	192	192
query54	292	229	225	225
query55	72	71	66	66
query56	319	292	284	284
query57	1335	1311	1219	1219
query58	289	258	244	244
query59	1578	1623	1431	1431
query60	305	266	251	251
query61	150	149	155	149
query62	542	492	440	440
query63	237	202	205	202
query64	2771	1039	884	884
query65	4687	4666	4608	4608
query66	1791	496	373	373
query67	29319	29219	29196	29196
query68	3320	1532	1014	1014
query69	418	297	266	266
query70	918	815	796	796
query71	362	345	332	332
query72	3082	2698	2345	2345
query73	817	767	415	415
query74	5044	4913	4701	4701
query75	2540	2511	2133	2133
query76	2344	1169	755	755
query77	346	384	280	280
query78	11923	11967	11232	11232
query79	1217	1140	723	723
query80	598	565	477	477
query81	462	341	290	290
query82	235	156	124	124
query83	318	318	291	291
query84	278	162	131	131
query85	906	618	510	510
query86	291	238	222	222
query87	1816	1823	1763	1763
query88	3676	2807	2755	2755
query89	418	367	339	339
query90	2196	193	191	191
query91	201	188	159	159
query92	77	60	58	58
query93	1553	1559	1001	1001
query94	559	345	333	333
query95	835	515	494	494
query96	1029	815	369	369
query97	2629	2665	2483	2483
query98	219	207	205	205
query99	1102	1118	1000	1000
Total cold run time: 262197 ms
Total hot run time: 176627 ms

@hello-stephen

Copy link
Copy Markdown
Contributor
ClickBench: Total hot run time: 24.88 s
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit 89257f09d3fb2a9fd4b333373ba16e5c64754073, data reload: false

query1	0.00	0.00	0.01
query2	0.10	0.06	0.05
query3	0.25	0.13	0.14
query4	1.60	0.14	0.15
query5	0.24	0.23	0.22
query6	1.25	1.04	1.10
query7	0.04	0.01	0.00
query8	0.05	0.03	0.04
query9	0.38	0.31	0.30
query10	0.55	0.58	0.54
query11	0.19	0.14	0.13
query12	0.18	0.15	0.14
query13	0.47	0.48	0.48
query14	1.01	1.00	0.99
query15	0.61	0.60	0.59
query16	0.32	0.31	0.31
query17	1.08	1.09	1.10
query18	0.21	0.20	0.21
query19	2.04	1.97	1.95
query20	0.01	0.01	0.02
query21	15.42	0.22	0.14
query22	4.82	0.06	0.05
query23	16.16	0.30	0.12
query24	2.95	0.41	0.32
query25	0.10	0.05	0.04
query26	0.73	0.20	0.14
query27	0.04	0.04	0.03
query28	3.57	0.93	0.54
query29	12.51	4.02	3.24
query30	0.27	0.15	0.16
query31	2.77	0.62	0.31
query32	3.23	0.59	0.48
query33	3.22	3.20	3.28
query34	15.60	4.17	3.46
query35	3.52	3.53	3.53
query36	0.56	0.43	0.43
query37	0.10	0.06	0.07
query38	0.05	0.04	0.04
query39	0.04	0.03	0.03
query40	0.19	0.17	0.15
query41	0.08	0.03	0.02
query42	0.03	0.03	0.04
query43	0.04	0.03	0.04
Total cold run time: 96.58 s
Total hot run time: 24.88 s

@morningman

Copy link
Copy Markdown
Contributor Author

run feut

@hello-stephen

Copy link
Copy Markdown
Contributor

FE UT Coverage Report

Increment line coverage `` 🎉
Increment coverage report
Complete coverage report

@morningman

Copy link
Copy Markdown
Contributor Author

run feut

@morningman morningman closed this Jul 29, 2026
@morningman morningman reopened this Jul 29, 2026
morningman and others added 5 commits July 29, 2026 23:07
Every test class deriving from TestWithFeService spends ~12s in
createDorisCluster(), of which ~10s is pure idle waiting.

Daemon.run() executes one cycle before sleeping, so HeartbeatMgr's first
cycle completes while createDorisCluster() has not registered any backend
yet. checkBEHeartbeat() therefore has to wait for the second cycle, which
is heartbeat_interval_second (10s by default) away.

Two changes:

- Set heartbeat_interval_second to 1 at the start of beforeAll(). It is
  placed before beforeCreatingConnectContext() so subclasses that set the
  interval explicitly (DecommissionBackendTest, BeDownCancelCloneTest)
  still win, and before the Env singleton is created so HeartbeatMgr picks
  up the new interval. It is deliberately not put into MockedFrontend's
  MIN_FE_CONF, because DorisFE.start() would then load it from fe.conf and
  silently override those subclasses.

- Make checkBEHeartbeatStatus() check before sleeping and poll at 20ms
  instead of sleeping a fixed 1s before each check. The overall timeout
  budget is unchanged.

Measured on 20 nereids command test classes (43 tests, all passing before
and after):

  fork=1  wall 399s -> 211s, reported test time 283s -> 95s
  fork=4  wall 399s -> 67s

A synthetic class that only starts the FE and asserts once goes from
12.0s to 2.83s.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Every FE unit test class pays a full FE startup. Measured on the FE UT CI
agent (build 1008420), that fixed cost is about 54s per class: ~16s of JVM
fork and class loading (measured from test classes that never start an FE)
plus ~38s of FE startup.

210 of the 214 nereids test classes that start an FE finish in under 90s,
i.e. they are almost entirely that fixed cost. Merging classes that already
share the exact same fixture removes it without changing any test.

This first batch merges 12 classes that all extend SqlTestBase and override
no setup at all, so they already ran against an identical fixture (database
"test" with tables T0..T4):

  sqltest/SqlPlanSuiteTest                  <- CascadesJoinReorderTest, InferTest,
                                               JoinTest, MultiJoinTest, SortTest
  rules/exploration/mv/MvExplorationSuiteTest <- BuildStructInfoTest, EliminateJoinTest,
                                               HyperGraphAggTest, HyperGraphComparatorTest,
                                               NullRejectInferenceTest
  rules/rewrite/RewriteRuleSuiteTest        <- PruneOlapScanTabletTest,
                                               EliminateConstHashJoinConditionTest

Test bodies are moved verbatim; method names are unchanged so test reports
keep the same identifiers. Each merged file keeps a "from <OriginalClass>"
section header, so grepping the old class name still lands on its tests.

Verified: 53 tests before, 53 tests after, all passing.

Deliberately not merged here:
- nereids/mv (6 classes): they create materialized views with colliding names
  inside their test methods, so sharing one FE makes them interfere. Needs
  namespace isolation first.
- jobs/joinorder/hypergraph (4 classes): testPullUpQueryFilter exists with
  different bodies in two of them.
- Classes with real work (DistributeHintTest 764s, OtherJoinTest 256s,
  GraphSimplifierConsistencyTest 223s, PreMaterializedViewRewriterTest 205s)
  are intentionally left alone: merging them would create a straggler that
  hurts wall clock under the 12-way parallel CI run.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
… 95%

nereids/jobs/joinorder/joinhint/DistributeHintTest was the slowest class in
the whole FE UT suite: 764s in CI build 1008420, 459s in 1008517. The 40%
swing is not noise, the test is unseeded and the amount of work it does
varies per run.

It also had no assertions at all, and never had any since it was added in
apache#28562: mismatches were counted into a field and printed to stdout, so no
optimizer regression could ever fail it. Two of its 182 local seconds were
useful; the rest was enumeration that could not report anything.

Both properties it covers are worth keeping, so the tests are kept and made
able to fail:

- testHintJoin: a distribute hint (broadcast / shuffle) selects a physical
  strategy and must never change the result. This is the only coverage of
  distribute hints over random join graphs. Enumeration unchanged (~910
  optimizations, ~5s); it now asserts.

- testLeading: reordering *inner* joins is always semantics-preserving, so
  any leading order must give the same result as the un-hinted plan. It now
  builds inner-join-only graphs via the existing
  HyperGraphBuilderOld(Set<JoinType>) constructor, draws permutations from a
  fixed seed, and asserts. Enumeration is cut from ~51000 optimizations to
  ~280, which is what made the class slow.

The previous testLeading applied a random permutation to graphs that also
contained outer / semi / anti joins, where an arbitrary leading order is
generally not a valid join order. Asserting on that case fails reproducibly
(3/3 runs, down to 3 tables): extra null-padded rows appear. Whether Doris
should reject such a hint instead of applying it is a question for the
Nereids owners, so that case is kept as a @disabled test documenting the
repro rather than asserting behaviour nobody has decided.

Local runtime: 182s -> 9-10s over three runs, all passing.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
26 test classes install a Mockito spy over Env.accessManager (and a few over
systemInfo / authenticationIntegrationMgr) with Deencapsulation.setField and
never put the original back. Each subsequent test method in the same JVM then
spies the previous spy, so the wrappers stack up for the life of the class.

TestWithFeService now captures those three fields once class setup is done and
restores them after every test method.

Capturing after runBeforeAll() rather than before each test is deliberate:
CheckRowPolicyTest installs a spy for the whole class inside runBeforeAll(), so
that spy becomes its baseline and the restore is a no-op there. Capturing
earlier would have torn its spy down after the first test method.

Honest scope note: this was written as a prerequisite for merging spy-using
test classes, but it turned out not to be required for that. Merging six of
them passes with this commit reverted, because each test re-reads the manager
and re-stubs what it needs. What this commit fixes is the unbounded spy
nesting and the latent cross-test contamination, not a failure observed today.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Six classes under nereids/trees/plans/commands each started a full FE to run
two or three validate() assertions with a spied access manager. On the CI
agent that fixed cost is about 50s per class, so the six cost roughly 300s of
test time for 13 assertions.

They are merged into CommandPrivilegeValidationTest:

  AdminRepairTableCommandTest, AdminCopyTabletCommandTest,
  AlterColumnStatsCommandTest, CleanQueryStatsCommandTest,
  ShowQueryStatsCommandTest, ShowTabletsFromTableCommandTest

Members that were byte-identical across the originals (connectContext, env,
accessControllerManager, internalCtl) are declared once. Test methods whose
names collided -- testValidateNormal, testValidateNoPrivilege,
testValidateWithPrivilege and the per-class runBefore() helper -- are prefixed
with their original class, so grepping the old class name still lands on its
tests and the names now say which command they cover.

Two databases had to be renamed. AlterColumnStats and CleanQueryStats both
created a database literally called "test_db", and CatalogMocker.TEST_DB_NAME
is also "test_db", so sharing one FE made the second createDatabase() fail
with "database exists". Each section now creates its own database.

Verified: 13 tests before, 13 tests after, passing on two consecutive runs.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@morningman

Copy link
Copy Markdown
Contributor Author

run feut

@hello-stephen

Copy link
Copy Markdown
Contributor

FE UT Coverage Report

Increment line coverage `` 🎉
Increment coverage report
Complete coverage report

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants